consoleproxy: fix race where the capacity scanner restarts a console proxy while it is being destroyed - #14175

Description

When a console proxy is destroyed (destroySystemVm, HA, or the scanner recycling a proxy it failed to start), destroyProxy calls expunge, which stops the VM and only then moves it to Expunging. The console proxy scanner (allocCapacity) takes a proxy in Starting, Stopped, Migrating or Stopping state from its stopped pool and starts it, and nothing ties that to a destroy in progress. If a scan runs while the destroy has the proxy in Stopping or Stopped, the scanner starts it again and the destroy fails with:

Unable to expunge the vm because it is not in the correct state

In Trillian runs this shows up as test_02_list_cpvm_vm and test_04_cpvm_internals in test_ssvm.py failing with "Check list response returns a valid list" (for example tid-16943 on #13090 and tid-16931 on #14038): the destroy in the first pass of the file loses the race, the file is rerun, and the rerun lists Running console proxies before the restarted one is back.

The scanner already takes the console proxy allocation lock (consoleproxy.alloc) when it creates a new proxy. This takes the same lock for the whole scan, so picking and starting a stopped proxy is covered too, and in destroyProxy around the stop and expunge. GlobalLock is reentrant, so the scanner recycling a proxy it failed to start still works. If destroyProxy cannot get the lock within the existing 180 second timeout it logs a warning and destroys the proxy as before.

Types of changes

• Breaking change (fix or feature that would cause existing functionality to change)
• New feature (non-breaking change which adds functionality)
• Bug fix (non-breaking change which fixes an issue)
• Enhancement (improves an existing feature and functionality)
• Cleanup (Code refactoring and cleanup, that may add test cases)
• build/CI
• test (unit or integration test code)

Feature/Enhancement Scale or Bug Severity

Feature/Enhancement Scale

• Major
• Minor

Bug Severity

• BLOCKER
• Critical
• Major
• Minor
• Trivial

Screenshots (if appropriate):

N/A

How Has This Been Tested?

Unit tests in ConsoleProxyManagerImplTest: destroyProxy holds the lock around the expunge, still destroys when the lock is busy, the scan is skipped while the lock is busy, and a stopped proxy is picked and started while the lock is held. Three of the four fail without the change (the busy lock destroy case keeps the old behaviour on purpose), and the class passes with it.

Live on a KVM zone, with the changed classes swapped into the management server. The scanner skips a zone while a proxy is Starting or Stopping, so the window is between the proxy reaching Stopped and the destroy moving it to Expunging. On this zone that is about 30 ms (the Trillian logs above show about 2 seconds), so the race did not show up on its own: 0 of 15 destroys at the default 30 second scan interval, and 0 of 8 at a 1 second interval.

To make the window reproducible, a database trigger on the test zone delayed the completion of the stop job that belongs to a destroySystemVm job by 3 seconds, which keeps the proxy in Stopped for about 3 seconds before the destroy moves it to Expunging (measured 3.03 to 3.06 seconds on every destroy). With consoleproxy.capacityscan.interval at 1000 ms and 5 destroys each:

before    4 of 5 destroys: the scanner picked the proxy being destroyed from its stopped pool
          ("Found a stopped console proxy, starting it") and queued a start for it
after     0 of 5: the scanner waited for the lock, then found no stopped proxy
          ("No stopped console proxy is available") and created a new one

On this zone the scanner's start was queued behind the destroy's own stop job, so the destroy still completed and the queued start failed afterwards. On Trillian the stop job had already finished, the start ran first and the destroy failed as shown above.

How did you try to break it?

Destroyed the proxy repeatedly with a one second scan interval so every destroy overlaps several scans. The scanner path that recycles a proxy it could not start calls destroyProxy while it already holds the lock, which works because the lock is reentrant; the HA path also goes through destroyProxy. The "Unmatched Global lock consoleproxy.alloc reference usage detected" warning logged at management server shutdown was already there before this change.